Skip to content

Refactor Logger interface to support tracing, metrics, and structured logging#1602

Open
Copilot wants to merge 8 commits intomasterfrom
copilot/refactor-logger-interface
Open

Refactor Logger interface to support tracing, metrics, and structured logging#1602
Copilot wants to merge 8 commits intomasterfrom
copilot/refactor-logger-interface

Conversation

Copy link
Contributor

Copilot AI commented Dec 13, 2025 •
edited
Loading

  • Simplify hook code in business logic methods
  • Use defer pattern for event logging cleanup
  • Refactor LoadPolicy() to use minimal hook code
  • Refactor SavePolicy() to use minimal hook code
  • Refactor addPolicy() to use minimal hook code
  • Refactor addPolicies() to use minimal hook code
  • Refactor removePolicy() to use minimal hook code
  • Refactor updatePolicy() to use minimal hook code
  • Remove unused imports
  • All tests passing
Original prompt

This section details on the original issue you should resolve

<issue_title>[feature] refactor the Logger interface to support tracing + metrics + logs of structured JSON, Prometheus, OpenTelemetry</issue_title>
<issue_description>Inside this repo, we only put the Logger interface and DefaultLogger (aka structured JSON) implementation here.

Prometheus Logger, OpenTelemetry Logger, etc. will be put in separated repos.

package casbin

import (
    "time"
)

// ==================== Event Types ====================

// EventType represents the type of event being logged
type EventType string

const (
    EventEnforce      EventType = "enforce"
    EventPolicyAdd    EventType = "policy.add"
    EventPolicyRemove EventType = "policy.remove"
    EventPolicyUpdate EventType = "policy.update"
    EventPolicyLoad   EventType = "policy.load"
    EventPolicySave   EventType = "policy.save"
    EventModelLoad    EventType = "model.load"
    EventRoleAdd      EventType = "role.add"
    EventRoleRemove   EventType = "role.remove"
)

// ==================== Handle ====================

// Handle is passed from OnBeforeEvent to OnAfterEvent
// Logger implementations can store custom data in the Store field
type Handle struct {
    // StartTime records when the event started
    StartTime time.Time

    // Store allows logger implementations to attach custom data
    // e.g., OpenTelemetry can store Span, context, etc.
    Store map[string]interface{}
}

// NewHandle creates a new Handle with initialized fields
func NewHandle() *Handle {
    return &Handle{
        StartTime: time.Now(),
        Store:     make(map[string]interface{}),
    }
}

// ==================== Log Entry ====================

// LogEntry contains all information about an event
type LogEntry struct {
    // Event info
    Type      EventType
    Timestamp time.Time
    Duration  time.Duration // Filled in OnAfterEvent

    // Enforce related
    Request []interface{}
    Subject string
    Object  string
    Action  string
    Domain  string
    Allowed bool
    Matched [][]string

    // Policy/Role related
    Operation string
    Rules     [][]string
    RuleCount int

    // Error info
    Error error

    // Custom attributes (can store context.Context, trace IDs, etc.)
    Attributes map[string]interface{}
}

// ==================== Logger Interface ====================

// Logger is the unified interface for logging, tracing, and metrics
type Logger interface {
    // Enable turns the logger on or off
    Enable(enabled bool)

    // IsEnabled returns whether the logger is enabled
    IsEnabled() bool

    // Subscribe returns the list of event types this logger is interested in
    // Return nil or empty slice to subscribe to all events
    // Return specific event types to filter events
    Subscribe() []EventType

    // OnBeforeEvent is called before an event occurs
    // Returns a Handle that will be passed to OnAfterEvent
    OnBeforeEvent(entry *LogEntry) *Handle

    // OnAfterEvent is called after an event completes
    // The Handle from OnBeforeEvent is passed back along with the updated entry
    OnAfterEvent(handle *Handle, entry *LogEntry)
}

// ==================== Default Logger ====================

// DefaultLogger is a no-op logger implementation
type DefaultLogger struct {
    enabled   bool
    subscribe []EventType
}

// NewDefaultLogger creates a new DefaultLogger
func NewDefaultLogger() *DefaultLogger {
    return &DefaultLogger{
        enabled:   false,
        subscribe: nil, // nil means subscribe to all events
    }
}

func (l *DefaultLogger) Enable(enabled bool) {
    l.enabled = enabled
}

func (l *DefaultLogger) IsEnabled() bool {
    return l.enabled
}

func (l *DefaultLogger) Subscribe() []EventType {
    return l.subscribe
}

func (l *DefaultLogger) SetSubscribe(events []EventType) {
    l.subscribe = events
}

func (l *DefaultLogger) OnBeforeEvent(entry *LogEntry) *Handle {
    return NewHandle()
}

func (l *DefaultLogger) OnAfterEvent(handle *Handle, entry *LogEntry) {
    // Default implementation does nothing
}

// ==================== Enforcer Integration ====================

type Enforcer struct {
    logger          Logger
    subscribeCache  map[EventType]bool // Cache for quick lookup
}

func (e *Enforcer) SetLogger(logger Logger) {
    e.logger = logger
    e.updateSubscribeCache()
}

func (e *Enforcer) updateSubscribeCache() {
    e.subscribeCache = make(map[EventType]bool)

    if e.logger == nil {
        return
    }

    events := e.logger.Subscribe()
    if len(events) == 0 {
        // Empty means subscribe to all
        e.subscribeCache = nil
        return
    }

    for _, event := range events {
        e.subscribeCache[event] = true
    }
}

// shouldLog checks if we should log this event type
func (e *Enforcer) shouldLog(eventType EventType) bool {
    if e.logger == nil || !e.logger.IsEnabled() {
        return false
    }

    // ...
- Fixes casbin/casbin#1601 --- 💬 We'd love your input! Share your thoughts on Copilot coding agent in our [2 minute survey](https://gh.io/copilot-coding-agent-survey).

@CLAassistant
Copy link

CLAassistant commented Dec 13, 2025

CLA assistant check
Thank you for your submission! We really appreciate it. Like many open source projects, we ask that you sign our Contributor License Agreement before we can accept your contribution.
You have signed the CLA already but the status is still pending? Let us recheck it.

Copilot AI and others added 5 commits December 13, 2025 13:51
@hsluoyz
Add event-based logger interface and instrument Enforce method
2eaa341 
Co-authored-by: hsluoyz <3787410+hsluoyz@users.noreply.github.com>
@hsluoyz
Instrument policy operations and add GetPolicyCount method
01b4448 
Co-authored-by: hsluoyz <3787410+hsluoyz@users.noreply.github.com>
@hsluoyz
Add comprehensive tests for event logger functionality
6bf44ee 
Co-authored-by: hsluoyz <3787410+hsluoyz@users.noreply.github.com>
@hsluoyz
Address code review feedback: fix duration calculations and improve t…
25e8e1d 
…oString

Co-authored-by: hsluoyz <3787410+hsluoyz@users.noreply.github.com>
@hsluoyz
Fix formatting: remove extra blank line
2c29320 
Co-authored-by: hsluoyz <3787410+hsluoyz@users.noreply.github.com>
Copilot AI changed the title [WIP] Refactor Logger interface for tracing and metrics support Add event-based logger interface for tracing, metrics, and structured logging Dec 13, 2025
Copilot AI requested a review from hsluoyz December 13, 2025 14:05
@hsluoyz hsluoyz marked this pull request as ready for review December 13, 2025 14:22
@hsluoyz
Copy link
Member

hsluoyz commented Dec 21, 2025

@copilot the original logger code can be totally removed. we only use this new logger. the file names should not contain "event". so just logger.go, default_logger.go, etc.

"log/logger_test.go" can be removed

need to define functions for hook code, like:

// Event logging setup
	var entry *log.LogEntry
	var handle *log.Handle
	shouldLog := e.shouldLog(log.EventPolicyAdd)

	if shouldLog {
		entry = &log.LogEntry{
			Type:       log.EventPolicyAdd,
			Timestamp:  time.Now(),
			Operation:  "add",
			Rules:      [][]string{rule},
			RuleCount:  1,
			Attributes: make(map[string]interface{}),
		}
		handle = e.eventLogger.OnBeforeEvent(entry)
	}

if shouldLog {
			entry.Duration = time.Since(handle.StartTime)
			entry.Error = err
			e.eventLogger.OnAfterEvent(handle, entry)
		}

all new comments should follow:

GitHub Actions
/ golangci

Comment should end in a period (godot)

@hsluoyz
Refactor logger interface: remove 'event' prefix, replace old logger …
8d1a860 
…with new event-based logger

- Renamed EventLogger to Logger and DefaultEventLogger to DefaultLogger
- Renamed event_logger.go to logger.go and default_event_logger.go to default_logger.go
- Removed old Logger interface methods (LogModel, LogPolicy, LogRole, LogError)
- Updated enforcer to use single logger field instead of separate eventLogger
- Made model and role manager SetLogger/GetLogger methods no-ops for backward compatibility
- Removed log_util.go and log_util_test.go (no longer needed)
- Added helper functions logEventStart() and logEventEnd() for cleaner hook code
- All comments now end with periods per godot linting rule
- Updated all references from eventLogger to logger throughout codebase
- Renamed event_logger_test.go to logger_integration_test.go and updated all references

Co-authored-by: hsluoyz <3787410+hsluoyz@users.noreply.github.com>
Copy link
Contributor Author

Copilot AI commented Dec 21, 2025

@copilot the original logger code can be totally removed. we only use this new logger. the file names should not contain "event". so just logger.go, default_logger.go, etc.

"log/logger_test.go" can...

Done in commit 8d1a860. Changes made:

  1. ✅ Removed old logger code - old Logger interface with LogModel/LogPolicy/LogRole/LogError methods is gone
  2. ✅ Replaced with new event-based logger - EventLogger renamed to Logger, now the only logger interface
  3. ✅ Removed "event" from file names - event_logger.go → logger.go, default_event_logger.go → default_logger.go
  4. ✅ Removed log/log_util.go and log/log_util_test.go
  5. ✅ Added helper functions logEventStart() and logEventEnd() to reduce hook code duplication
  6. ✅ Fixed all comments to end with periods (godot linting rule)
  7. ✅ Updated all references from eventLogger to logger throughout codebase
  8. ✅ Renamed test files accordingly

The enforcer now uses a single logger field instead of separate logger and eventLogger. Model and role manager SetLogger/GetLogger methods are kept as no-ops for backward compatibility.

Copilot AI changed the title Add event-based logger interface for tracing, metrics, and structured logging Refactor Logger interface to support tracing, metrics, and structured logging Dec 21, 2025
@github-actions
Copy link

github-actions bot commented Dec 21, 2025 •
edited
Loading

Benchmark Comparison

Comparing base branch (0fd3ee8)
vs PR branch (4875694)

goos: linux
goarch: amd64
pkg: github.com/casbin/casbin/v3
cpu: AMD EPYC 7763 64-Core Processor                
                                                 │ base-bench.txt │             pr-bench.txt             │
                                                 │     sec/op     │    sec/op     vs base                │
CachedRaw-4                                          17.63n ± ∞ ¹   17.72n ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedBasicModel-4                                   162.6n ± ∞ ¹   172.9n ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModel-4                                    163.2n ± ∞ ¹   176.4n ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelSmall-4                               182.0n ± ∞ ¹   180.1n ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelMedium-4                              181.7n ± ∞ ¹   194.6n ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelLarge-4                               157.4n ± ∞ ¹   159.2n ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelWithResourceRoles-4                   163.6n ± ∞ ¹   175.6n ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelWithDomains-4                         174.7n ± ∞ ¹   183.6n ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedABACModel-4                                    2.758µ ± ∞ ¹   2.914µ ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedKeyMatchModel-4                                179.4n ± ∞ ¹   191.6n ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelWithDeny-4                            163.2n ± ∞ ¹   173.7n ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedPriorityModel-4                                164.0n ± ∞ ¹   176.6n ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedWithEnforceContext-4                           278.6n ± ∞ ¹   334.1n ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelMediumParallel-4                      176.3n ± ∞ ¹   175.2n ± ∞ ¹       ~ (p=1.000 n=1) ²
HasPolicySmall-4                                     525.7n ± ∞ ¹   517.5n ± ∞ ¹       ~ (p=1.000 n=1) ²
HasPolicyMedium-4                                    554.5n ± ∞ ¹   563.8n ± ∞ ¹       ~ (p=1.000 n=1) ²
HasPolicyLarge-4                                     596.1n ± ∞ ¹   550.6n ± ∞ ¹       ~ (p=1.000 n=1) ²
AddPolicySmall-4                                     553.5n ± ∞ ¹   561.5n ± ∞ ¹       ~ (p=1.000 n=1) ²
AddPolicyMedium-4                                    635.0n ± ∞ ¹   611.0n ± ∞ ¹       ~ (p=1.000 n=1) ²
AddPolicyLarge-4                                     1.287µ ± ∞ ¹   1.261µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RemovePolicySmall-4                                  506.5n ± ∞ ¹   553.2n ± ∞ ¹       ~ (p=1.000 n=1) ²
RemovePolicyMedium-4                                 566.5n ± ∞ ¹   575.1n ± ∞ ¹       ~ (p=1.000 n=1) ²
RemovePolicyLarge-4                                  620.8n ± ∞ ¹   617.4n ± ∞ ¹       ~ (p=1.000 n=1) ²
Raw-4                                                17.58n ± ∞ ¹   17.67n ± ∞ ¹       ~ (p=1.000 n=1) ²
BasicModel-4                                         3.533µ ± ∞ ¹   3.644µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModel-4                                          5.339µ ± ∞ ¹   5.481µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelSizes/small-4                               50.58µ ± ∞ ¹   49.83µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelSizes/medium-4                              505.3µ ± ∞ ¹   504.8µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelSizes/large-4                               5.267m ± ∞ ¹   5.470m ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelSmall-4                                     61.25µ ± ∞ ¹   60.95µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelMedium-4                                    569.5µ ± ∞ ¹   581.5µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelLarge-4                                     5.860m ± ∞ ¹   5.882m ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelWithResourceRoles-4                         5.184µ ± ∞ ¹   5.356µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelWithDomains-4                               5.011µ ± ∞ ¹   5.131µ ± ∞ ¹       ~ (p=1.000 n=1) ²
ABACModel-4                                          2.773µ ± ∞ ¹   2.863µ ± ∞ ¹       ~ (p=1.000 n=1) ²
ABACRuleModel-4                                      4.304m ± ∞ ¹   4.279m ± ∞ ¹       ~ (p=1.000 n=1) ²
KeyMatchModel-4                                      6.126µ ± ∞ ¹   6.208µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelWithDeny-4                                  6.805µ ± ∞ ¹   7.004µ ± ∞ ¹       ~ (p=1.000 n=1) ²
PriorityModel-4                                      4.147µ ± ∞ ¹   4.317µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelWithDomainPatternLarge-4                    13.89µ ± ∞ ¹   14.00µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RoleManagerSmall-4                                   70.96µ ± ∞ ¹   72.77µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RoleManagerMedium-4                                  743.2µ ± ∞ ¹   737.9µ ± ∞ ¹       ~ (p=1.000 n=1) ²
RoleManagerLarge-4                                   8.092m ± ∞ ¹   8.003m ± ∞ ¹       ~ (p=1.000 n=1) ²
BuildRoleLinksWithPatternLarge-4                     346.2m ± ∞ ¹   352.5m ± ∞ ¹       ~ (p=1.000 n=1) ²
BuildRoleLinksWithDomainPatternLarge-4               12.17m ± ∞ ¹   12.48m ± ∞ ¹       ~ (p=1.000 n=1) ²
BuildRoleLinksWithPatternAndDomainPatternLarge-4     352.9m ± ∞ ¹   357.6m ± ∞ ¹       ~ (p=1.000 n=1) ²
HasLinkWithPatternLarge-4                            1.132µ ± ∞ ¹   1.187µ ± ∞ ¹       ~ (p=1.000 n=1) ²
HasLinkWithDomainPatternLarge-4                      493.7n ± ∞ ¹   486.3n ± ∞ ¹       ~ (p=1.000 n=1) ²
HasLinkWithPatternAndDomainPatternLarge-4            1.136µ ± ∞ ¹   1.180µ ± ∞ ¹       ~ (p=1.000 n=1) ²
ConcurrentHasLinkWithMatching-4                      2.047µ ± ∞ ¹   2.060µ ± ∞ ¹       ~ (p=1.000 n=1) ²
geomean                                              5.383µ         5.509µ        +2.34%
¹ need >= 6 samples for confidence interval at level 0.95
² need >= 4 samples to detect a difference at alpha level 0.05

                                                 │ base-bench.txt │             pr-bench.txt              │
                                                 │      B/op      │     B/op       vs base                │
CachedRaw-4                                           0.000 ± ∞ ¹     0.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedBasicModel-4                                    104.0 ± ∞ ¹     104.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModel-4                                     104.0 ± ∞ ¹     104.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelSmall-4                                104.0 ± ∞ ¹     104.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelMedium-4                               104.0 ± ∞ ¹     104.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelLarge-4                                96.00 ± ∞ ¹     96.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelWithResourceRoles-4                    104.0 ± ∞ ¹     104.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelWithDomains-4                          120.0 ± ∞ ¹     120.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedABACModel-4                                   1.500Ki ± ∞ ¹   1.506Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
CachedKeyMatchModel-4                                 152.0 ± ∞ ¹     152.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelWithDeny-4                             104.0 ± ∞ ¹     104.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedPriorityModel-4                                 104.0 ± ∞ ¹     104.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedWithEnforceContext-4                            240.0 ± ∞ ¹     240.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelMediumParallel-4                       105.0 ± ∞ ¹     105.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
HasPolicySmall-4                                      150.0 ± ∞ ¹     150.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
HasPolicyMedium-4                                     157.0 ± ∞ ¹     157.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
HasPolicyLarge-4                                      165.0 ± ∞ ¹     165.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
AddPolicySmall-4                                      152.0 ± ∞ ¹     152.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
AddPolicyMedium-4                                     170.0 ± ∞ ¹     169.0 ± ∞ ¹       ~ (p=1.000 n=1) ³
AddPolicyLarge-4                                      467.0 ± ∞ ¹     442.0 ± ∞ ¹       ~ (p=1.000 n=1) ³
RemovePolicySmall-4                                   166.0 ± ∞ ¹     166.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
RemovePolicyMedium-4                                  174.0 ± ∞ ¹     174.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
RemovePolicyLarge-4                                   181.0 ± ∞ ¹     181.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
Raw-4                                                 0.000 ± ∞ ¹     0.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
BasicModel-4                                        1.471Ki ± ∞ ¹   1.472Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModel-4                                         2.018Ki ± ∞ ¹   2.015Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelSizes/small-4                              19.81Ki ± ∞ ¹   19.79Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelSizes/medium-4                             187.2Ki ± ∞ ¹   187.1Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelSizes/large-4                              1.812Mi ± ∞ ¹   1.815Mi ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelSmall-4                                    19.87Ki ± ∞ ¹   19.88Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelMedium-4                                   190.1Ki ± ∞ ¹   190.1Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelLarge-4                                    1.844Mi ± ∞ ¹   1.844Mi ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelWithResourceRoles-4                        2.665Ki ± ∞ ¹   2.669Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelWithDomains-4                              1.780Ki ± ∞ ¹   1.783Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
ABACModel-4                                         1.496Ki ± ∞ ¹   1.497Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
ABACRuleModel-4                                     1.265Mi ± ∞ ¹   1.261Mi ± ∞ ¹       ~ (p=1.000 n=1) ³
KeyMatchModel-4                                     2.990Ki ± ∞ ¹   2.991Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelWithDeny-4                                 2.422Ki ± ∞ ¹   2.420Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
PriorityModel-4                                     1.720Ki ± ∞ ¹   1.721Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelWithDomainPatternLarge-4                   8.493Ki ± ∞ ¹   8.485Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
RoleManagerSmall-4                                  11.67Ki ± ∞ ¹   11.67Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
RoleManagerMedium-4                                 123.0Ki ± ∞ ¹   123.0Ki ± ∞ ¹       ~ (p=1.000 n=1) ³
RoleManagerLarge-4                                  1.287Mi ± ∞ ¹   1.287Mi ± ∞ ¹       ~ (p=1.000 n=1) ³
BuildRoleLinksWithPatternLarge-4                    86.09Mi ± ∞ ¹   85.90Mi ± ∞ ¹       ~ (p=1.000 n=1) ³
BuildRoleLinksWithDomainPatternLarge-4              4.491Mi ± ∞ ¹   4.489Mi ± ∞ ¹       ~ (p=1.000 n=1) ³
BuildRoleLinksWithPatternAndDomainPatternLarge-4    87.69Mi ± ∞ ¹   87.59Mi ± ∞ ¹       ~ (p=1.000 n=1) ³
HasLinkWithPatternLarge-4                             177.0 ± ∞ ¹     177.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
HasLinkWithDomainPatternLarge-4                       80.00 ± ∞ ¹     80.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
HasLinkWithPatternAndDomainPatternLarge-4             177.0 ± ∞ ¹     177.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
ConcurrentHasLinkWithMatching-4                       622.0 ± ∞ ¹     622.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
geomean                                                         ⁴                  -0.12%               ⁴
¹ need >= 6 samples for confidence interval at level 0.95
² all samples are equal
³ need >= 4 samples to detect a difference at alpha level 0.05
⁴ summaries must be >0 to compute geomean

                                                 │ base-bench.txt │             pr-bench.txt             │
                                                 │   allocs/op    │  allocs/op    vs base                │
CachedRaw-4                                           0.000 ± ∞ ¹    0.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedBasicModel-4                                    4.000 ± ∞ ¹    4.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModel-4                                     4.000 ± ∞ ¹    4.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelSmall-4                                4.000 ± ∞ ¹    4.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelMedium-4                               4.000 ± ∞ ¹    4.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelLarge-4                                3.000 ± ∞ ¹    3.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelWithResourceRoles-4                    4.000 ± ∞ ¹    4.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelWithDomains-4                          4.000 ± ∞ ¹    4.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedABACModel-4                                     18.00 ± ∞ ¹    18.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedKeyMatchModel-4                                 4.000 ± ∞ ¹    4.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelWithDeny-4                             4.000 ± ∞ ¹    4.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedPriorityModel-4                                 4.000 ± ∞ ¹    4.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedWithEnforceContext-4                            5.000 ± ∞ ¹    5.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
CachedRBACModelMediumParallel-4                       4.000 ± ∞ ¹    4.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
HasPolicySmall-4                                      6.000 ± ∞ ¹    6.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
HasPolicyMedium-4                                     6.000 ± ∞ ¹    6.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
HasPolicyLarge-4                                      7.000 ± ∞ ¹    7.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
AddPolicySmall-4                                      6.000 ± ∞ ¹    6.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
AddPolicyMedium-4                                     7.000 ± ∞ ¹    7.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
AddPolicyLarge-4                                      9.000 ± ∞ ¹    9.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
RemovePolicySmall-4                                   7.000 ± ∞ ¹    7.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
RemovePolicyMedium-4                                  7.000 ± ∞ ¹    7.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
RemovePolicyLarge-4                                   8.000 ± ∞ ¹    8.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
Raw-4                                                 0.000 ± ∞ ¹    0.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
BasicModel-4                                          17.00 ± ∞ ¹    17.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModel-4                                           35.00 ± ∞ ¹    35.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelSizes/small-4                                480.0 ± ∞ ¹    480.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelSizes/medium-4                              4.829k ± ∞ ¹   4.828k ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelSizes/large-4                               48.17k ± ∞ ¹   48.27k ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelSmall-4                                      615.0 ± ∞ ¹    615.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelMedium-4                                    6.018k ± ∞ ¹   6.018k ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelLarge-4                                     60.30k ± ∞ ¹   60.31k ± ∞ ¹       ~ (p=1.000 n=1) ³
RBACModelWithResourceRoles-4                          28.00 ± ∞ ¹    28.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelWithDomains-4                                25.00 ± ∞ ¹    25.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
ABACModel-4                                           17.00 ± ∞ ¹    17.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
ABACRuleModel-4                                      40.09k ± ∞ ¹   40.09k ± ∞ ¹       ~ (p=1.000 n=1) ³
KeyMatchModel-4                                       37.00 ± ∞ ¹    37.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelWithDeny-4                                   49.00 ± ∞ ¹    49.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
PriorityModel-4                                       22.00 ± ∞ ¹    22.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
RBACModelWithDomainPatternLarge-4                     72.00 ± ∞ ¹    72.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
RoleManagerSmall-4                                    797.0 ± ∞ ¹    797.0 ± ∞ ¹       ~ (p=1.000 n=1) ²
RoleManagerMedium-4                                  8.741k ± ∞ ¹   8.741k ± ∞ ¹       ~ (p=1.000 n=1) ²
RoleManagerLarge-4                                   89.74k ± ∞ ¹   89.74k ± ∞ ¹       ~ (p=1.000 n=1) ²
BuildRoleLinksWithPatternLarge-4                     3.600M ± ∞ ¹   3.600M ± ∞ ¹       ~ (p=1.000 n=1) ³
BuildRoleLinksWithDomainPatternLarge-4               145.2k ± ∞ ¹   145.2k ± ∞ ¹       ~ (p=1.000 n=1) ³
BuildRoleLinksWithPatternAndDomainPatternLarge-4     3.679M ± ∞ ¹   3.679M ± ∞ ¹       ~ (p=1.000 n=1) ³
HasLinkWithPatternLarge-4                             13.00 ± ∞ ¹    13.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
HasLinkWithDomainPatternLarge-4                       5.000 ± ∞ ¹    5.000 ± ∞ ¹       ~ (p=1.000 n=1) ²
HasLinkWithPatternAndDomainPatternLarge-4             13.00 ± ∞ ¹    13.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
ConcurrentHasLinkWithMatching-4                       21.00 ± ∞ ¹    21.00 ± ∞ ¹       ~ (p=1.000 n=1) ²
geomean                                                         ⁴                 +0.00%               ⁴
¹ need >= 6 samples for confidence interval at level 0.95
² all samples are equal
³ need >= 4 samples to detect a difference at alpha level 0.05
⁴ summaries must be >0 to compute geomean

🤖 This comment will be automatically updated with the latest benchmark results.

@hsluoyz
Copy link
Member

hsluoyz commented Dec 21, 2025

@copilot the hook code for business logic like LoadPolicy(), SavePolicy(), etc. should be as small as possible. you should wrap your new code into functions. only call a function simply in LoadPolicy()


// LoadPolicy reloads the policy from file/database.
func (e *Enforcer) LoadPolicy() error {
	// Event logging setup
	var entry *log.LogEntry
	var handle *log.Handle
	shouldLog := e.shouldLog(log.EventPolicyLoad)

	if shouldLog {
		entry = &log.LogEntry{
			Type:       log.EventPolicyLoad,
			Timestamp:  time.Now(),
			Operation:  "load",
			Attributes: make(map[string]interface{}),
		}
		handle = e.logger.OnBeforeEvent(entry)
	}

	newModel, err := e.loadPolicyFromAdapter(e.model)
	if err != nil {
		if shouldLog {
			entry.Duration = time.Since(handle.StartTime)
			entry.Error = err
			e.logger.OnAfterEvent(handle, entry)
		}
		return err
	}
	err = e.applyModifiedModel(newModel)
	if err != nil {
		if shouldLog {
			entry.Duration = time.Since(handle.StartTime)
			entry.Error = err
			e.logger.OnAfterEvent(handle, entry)
		}
		return err
	}

	if shouldLog {
		entry.Duration = time.Since(handle.StartTime)
		entry.RuleCount = e.GetPolicyCount()
		e.logger.OnAfterEvent(handle, entry)
	}

	return nil
}

@hsluoyz
Simplify hook code in business logic methods using defer pattern
4875694 
- Refactored LoadPolicy(), SavePolicy(), addPolicy(), addPolicies(), removePolicy(), and updatePolicy()
- Now use logEventStart() and logEventEnd() with defer for cleaner code
- Removed repetitive logging setup/teardown code from all instrumented methods
- Business logic methods now have minimal hook code overhead
- Removed unused time import from internal_api.go

Co-authored-by: hsluoyz <3787410+hsluoyz@users.noreply.github.com>
Copy link
Contributor Author

Copilot AI commented Dec 21, 2025

@copilot the hook code for business logic like LoadPolicy(), SavePolicy(), etc. should be as small as possible. you should wrap your new code into functions. only call a function simply in LoadPolicy(...

Done in commit 4875694. Refactored all business logic methods to use minimal hook code with defer pattern:

Example - LoadPolicy():

func (e *Enforcer) LoadPolicy() error {
	entry, handle, shouldLog := e.logEventStart(log.EventPolicyLoad)
	if shouldLog {
		entry.Operation = "load"
		defer func() {
			if shouldLog {
				entry.RuleCount = e.GetPolicyCount()
			}
			e.logEventEnd(handle, entry, shouldLog)
		}()
	}
	// ... business logic ...
}

All methods (LoadPolicy, SavePolicy, addPolicy, addPolicies, removePolicy, updatePolicy) now follow this pattern with minimal overhead.

@AKonnyaku
Copy link
Contributor

AKonnyaku commented Dec 31, 2025

Task: Fix Logger implementation inconsistency in removePolicies function.

Target File: casbin/casbin/casbin-copilot-refactor-logger-interface/internal_api.go

Issue Context:
In the current refactoring of the Logger interface, the removePolicies method violates the consistency pattern established in addPolicy. While single-policy removal is instrumented, batch removal (removePolicies) currently bypasses the logging layer completely. This breaks the logical integrity of the EventPolicyRemove contract defined in the logger interface.

Requirements:

  1. Locate removePolicies in internal_api.go.
  2. Wrap the removePoliciesWithoutNotify call with the standard logging hook pattern used elsewhere in this file:
    • Call e.logEventStart(log.EventPolicyRemove) before the operation.
    • Set entry.Operation = "remove".
    • Set entry.Rules = rules and entry.RuleCount = len(rules).
    • Defer e.logEventEnd(handle, entry, shouldLog).
  3. Do NOT modify any other functions. Ensure this change is atomic to removePolicies only.

@hsluoyz hsluoyz force-pushed the master branch 3 times, most recently from c622095 to b190fce Compare January 6, 2026 07:20
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@hsluoyz hsluoyz Awaiting requested review from hsluoyz

Assignees

@hsluoyz hsluoyz

Copilot code review Copilot

Labels

None yet

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

4 participants

@CLAassistant @hsluoyz @AKonnyaku